test: Break if DEBUG_ASSERT is encountered #2911
Conversation
|
I have not yet understand how logging relates the DEBUG_ASSERT. But let's release all from headaches and hold this back until the all test are working. |
It sounds like his should be decoupled. Right? |
Not necessarily. The elephant in the room is that tests will only work reliably (as in: they fail when shit hits the fan) when the The only way around this that I can think of would be to compile the Let's always do debug builds on the CI for PRs and testing our branches, and we can add a second build stage that is only executed when operating on a tag (not a PR/branch) and builds in release mode for deployment. |
|
My last commit should make CI builds fail until the debug assertions are fixed. When For CI testing we also just switch to debug builds, but I think if a user explicitly enabled the |
|
I will try to fix some issues in ControlObject/ControlPrivateDouble that seem to affect us now. Only the bare minimum, no more. |
Can you elaborate what issues you're referring to? |
|
#2918 Issues like leaking controls that are not removed from the internal, static hash map after finishing tests and that are causing subsequent tests to fail with debug assertions when registering new ControlObject instances. |
Holzhaus
force-pushed
the
test-debug-assert
branch
from
a2fa97c to
9ffeafe
Compare
|
I rebased to update the test failure logs (this PR is so small that I don't think rebasing is an issue here). |
Yes, please always rebase after prerequisite PRs have been merged. This PR should remain the icing on the cake, keeping track of the those changes until the tests finally succeed. |
Holzhaus
force-pushed
the
test-debug-assert
branch
from
9ffeafe to
29b9826
Compare
|
@daschuer Ping. We need your support for fixing the AutoDJ assertions and test failures. |
|
|
Holzhaus
force-pushed
the
test-debug-assert
branch
2 times, most recently
from
94dd960 to
d768229
Compare
Holzhaus
force-pushed
the
test-debug-assert
branch
from
d768229 to
9d13cb0
Compare
Until now, the `PlayerInfo` singleton was instantiated implicitly when it was first accessed. This commit makes the instantiation explicit by adding a dedicated `PlayerInfo::create()` method. When running tests directly via `mixxx-test` (i.e. not a via `ctest`), all tests will be executed in the *same* process. Thus, the singleton will be instantiated by the first test that accessses the instance, but stay alive until `mixxx-test` is terminated. The `PlayerInfo` instance will repeatedly call `updateCurrentlyPlayingDeck()` through the `timerEvent()` mehtod during its lifetime. This will access some COs, e.g. `[Master],num_decks`. Depending on the currently running test, these COs may or may not be present. When `QCoreApplication::processEvents()` is called, there might be a `timerEvent()` in the queue and will cause CO access. If the CO is *not* present for that test, the test will throw a `DEBUG_ASSERT`. By making the singleton instantiation more explicit, we can add `PlayerInfo::create()` and `PlayerInfo::destroy()` calls only to the constructor/destructor of text fixtures that need it, and ensure that the timer doesn't cause failed debug assertions in unrelated tests. This fixes the remaining `DEBUG_ASSERT` issues and paves the way for merging PR mixxxdj#2911.
Until now, the `PlayerInfo` singleton was instantiated implicitly when it was first accessed. This commit makes the instantiation explicit by adding a dedicated `PlayerInfo::create()` method. When running tests directly via `mixxx-test` (i.e. not a via `ctest`), all tests will be executed in the *same* process. Thus, the singleton will be instantiated by the first test that accessses the instance, but stay alive until `mixxx-test` is terminated. The `PlayerInfo` instance will repeatedly call `updateCurrentlyPlayingDeck()` through the `timerEvent()` mehtod during its lifetime. This will access some COs, e.g. `[Master],num_decks`. Depending on the currently running test, these COs may or may not be present. When `QCoreApplication::processEvents()` is called, there might be a `timerEvent()` in the queue and will cause CO access. If the CO is *not* present for that test, the test will throw a `DEBUG_ASSERT`. By making the singleton instantiation more explicit, we can add `PlayerInfo::create()` and `PlayerInfo::destroy()` calls only to the constructor/destructor of text fixtures that need it, and ensure that the timer doesn't cause failed debug assertions in unrelated tests. This fixes the remaining `DEBUG_ASSERT` issues and paves the way for merging PR mixxxdj#2911.
Holzhaus
force-pushed
the
test-debug-assert
branch
from
9d13cb0 to
854d005
Compare
|
I rebased on latest 2.3, all tests pass now both with ctest and when running |
|
Please rebase once again. We might also need to reduce the log level. The CI builds now fail because of the huge amount of debug log messages in some tests. |
Holzhaus
force-pushed
the
test-debug-assert
branch
from
854d005 to
d9a31e5
Compare
|
Done. CTest hides the test output and only shows it if a test failed. So if the build is terminated due to the long output, that should be a side effect of the failing test, not the cause. |
I don't think so. The GlobalTrackCache test is aborted while running without any failures: |
|
The log output might not be shown, but it seems to be written in any case. |
|
Change log level from Debug to Info during tests: Debug assertions still cause test failures as intended (tested locally). Waiting for CI: Seems to work, please cherry-pick. |
|
Hmm I'm still not sure if the log level messages is the actual cause of the issue but if you checked it then it probably is. However, I'd rather not disable debug messages for tests globally. Maybe we can add a flag or set it via an env var, so that you can still see debug messages when running locally. I'll poke around tomorrow. |
|
For the macOS/CMake build, i think the test times out:
See Line 4090: https://travis-ci.org/github/mixxxdj/mixxx/jobs/716093492#L4090 A timeout is considered a failure, which is why ctest then starts to print the logging output (which Travis cuts off). But the actual issue seems to be the timeout after 30 seconds. For SCons, the build fails due to the verbose log, so changing the test log level is needed anyway as long as we keep SCons. When we drop it, it'd prefer to go back to debug tbh. |
|
Thanks for customizing the log level during tests! Please fix the remaining formatting issues. Detailed logging is not particularly important for the CI builds which are only supposed to detect test failures. In case of any failures, you need to repeat the affected tests anyway. Test failures should be reproducible and you could enable more detailed logging on demand when analyzing failing tests. |
|
The time out for GlobalTrackCacheTest.concurrentDelete is tight and it fails infrequently on the poorly performing macOS VMs on Travis. Usually, it finishes in about ~25 sec. Unrelated to the changes in this PR. |
Holzhaus
force-pushed
the
test-debug-assert
branch
from
669b499 to
fdd9006
Compare
|
These changes greatly improve the confidence in our testing efforts and finally enable a huge amount of additional checks to detect issues early. Thank you! LGTM |
|
Master builds may now fail until #3006 has been merged. |
TODO:
[WiP] Fix AutoDJ debug assertions in tests #2929Autodj test debug assert #2951Add missing COs to MixxxTestFix CO debug assertions caused by the PlayerInfo timer mixer/playerinfo: Make implicit PlayerInfo creation explicit #2988If you build Mixxx in debug mode, this makes sure that debug assertions lead to test failures. This implementation is far from perfect, it does not work in release builds (since debug assertions are stripped in that case), but it would require some bigger changes to make it possible to enable debug assertions for tests but not mixxx itself. For now, always make sure to build tests in debug mode or with DEBUG_ASSERTS_FATAL=ON.
Note: This will lead to a bunch of test failures. Not sure if we want to merge this before we fix them, because it will lead to failed CI builds in unrelated branches.